Day 19 把 NCCL overlap 拆開後,還有一個問題沒回答:同一筆 collective 裡,各個 rank 是一起到,還是有人先到、有人晚到?
可以把 collective 想成八個人約在同一個集合點。早到的人要等,最後一個人到了之後,大家才一起往下走。放到 GPU timeline 上,先到的 rank 可能在 NCCL kernel 裡等其他人,最後到的 rank 反而幾乎不用等。結果就有點反直覺:kernel 最長的卡,可能只是等最久,不一定是拖慢大家的人。
這也是為什麼 message size ÷ duration 只能算應用層的有效速率,不能直接當成鏈路利用率。今天不再看七張卡各自的總帳,而是把同一筆 collective 橫向排在一起,看看誰先到、誰最後到,以及晚開始的原因到底在 CPU 還是 GPU。
今天要處理三件事:
本文沿用主檔 A 的 sample_0(repeat=5),分析範圍是 39.964–46.123 秒,工具版本為 nsys-ai v0.3.0-21-g1cc03b5。這是八卡作業,但 GPU kernel timeline 只錄到 device 1–7,因此跨卡結論只涵蓋這七張;缺少的 device 0 仍可能改變完整八卡的先後順序。
然後另外,本文說的 straggler,指的是「某一筆 collective 最後抵達的 rank」。它比較像一次集合遲到,不代表那張 GPU 永久故障,也不代表整段訓練都由它拖慢。
nccl_anomaly 找到什麼先用 nccl_anomaly 找出 duration 明顯高於同類平均的 NCCL kernel:
nsys-ai skill run nccl_anomaly megatron.sqlite \
--trim 39.964 46.123
── NCCL Anomalies ──
Op Type Duration Avg Ratio Stream
──────────────────────────────────────────────────────
ReduceScatter 59.091ms 7.388ms 8.0× 56
ReduceScatter 59.074ms 7.388ms 8.0× 56
ReduceScatter 59.073ms 7.388ms 8.0× 56
ReduceScatter 59.070ms 7.388ms 8.0× 56
ReduceScatter 59.065ms 7.388ms 8.0× 56
ReduceScatter 59.059ms 7.388ms 8.0× 56
AllGather 57.439ms 7.942ms 7.2× 56
...
表格很醒目,但還不能直接說「找到 20 次 straggler」。這裡有兩個細節。
第一,前六筆 ReduceScatter 的 duration 幾乎一樣,差不到 0.04 ms。比起六個互不相關的異常,它更像是同一筆 collective 在六張卡上留下的六個等待視角。
第二,這版工具預設只回傳最慢的 20 列,最後顯示的 630 total ops 又是第一列所屬的 ReduceScatter 總數,不是整份 profile 的 NCCL 總數。因此,不能把畫面上的「20」直接解讀成 20 個獨立事件。把 limit 放大後,門檻以上共有 37 列 kernel;真正要知道有幾次跨卡事件,仍得先把同一筆 collective 配對。
主檔 A 的 device 1–7,在 stream 56 都有 225 筆 collective:
AllGather: 135 筆
ReduceScatter: 90 筆
合計: 225 筆/device
我先把每張卡的 collective 依開始時間排序,再逐位比較類型。225 個位置全部一致,沒有任何一張多一筆、少一筆或順序不同,這才允許把七張卡的「第 k 筆」排在同一列。
只靠順序仍不是萬無一失;如果不同卡剛好各漏掉同類型的事件,序列還是可能看起來一樣。因此還要做第二個檢查:配對後的結束時間是否集中。結果很明顯:
結束時間的跨卡差距:p50 0.052 ms、p90 0.086 ms、最大 0.118 ms
開始時間的跨卡差距:p50 0.441 ms、p90 10.426 ms、最大 53.234 ms
結束時間幾乎對齊,開始時間卻能差到 53 ms。除了再次確認配對合理,這組數字也把 late arriver 的樣子畫得很清楚:同一筆 collective 不一定一起開始,但會在很接近的時間完成。
NCCL 的 device primitive 會在 GPU kernel 內等待 peer 的連線進度或資料就緒;不同 protocol 的細節不一樣,所以這裡不因為 kernel symbol 帶有 _LL 就認定實際一定走 LL。比較安全的說法是:
觀測到的 NCCL kernel duration
≈ 等待其他 rank 的時間 + 實際傳輸與歸約時間
以開始差距最大的第 200 筆(從 1 起算)為例,這是一筆 ReduceScatter:
把它畫成七條橫線後,方向就清楚了:這一筆裡,長 kernel 是先到後等待的 rank;短 kernel 才是最後抵達者。OSDI 2025 的大規模訓練研究也用相同現象分析 TP communication:不同 rank 的 kernel 開始時間不一樣,結束時間卻大致對齊,再從開始落差往上游追原因。
但別把這句話推成通則。若某張卡本身的網路路徑較慢、傳輸量不同,或同時有多個 rank 出問題,最長 duration 仍可能有其他意義。先比較同一筆 collective 的 start/end,再判斷誰在等誰;不要只靠總 duration 排名。

對 225 筆 collective 逐一記錄最早與最晚開始的 device:
| device | 最後開始次數 | 最早開始次數 |
|---|---|---|
| 1 | 74 | 30 |
| 2 | 35 | 10 |
| 3 | 21 | 15 |
| 4 | 47 | 20 |
| 5 | 11 | 61 |
| 6 | 9 | 65 |
| 7 | 28 | 24 |
乍看之下,device 1 最可疑:它最後開始 74 次,device 4 則是 47 次;device 5、6 最常排在前面。不過,「最後開始次數」只看名次,不看差多少。把開始差距超過 20 ms 的八次事件排除後,各卡平均只比當次最早者晚 0.8–1.4 ms。多數時候只是毫秒級時差,不能因為 device 1 拿了 74 次最後一名,就直接叫它壞卡。
stream 56 的 NCCL kernel 總時間也沒有和名次完全一一對應:
| device | stream 56 NCCL kernel time |
|---|---|
| 1 | 1,689.9 ms |
| 2 | 1,681.5 ms |
| 3 | 1,753.3 ms |
| 4 | 1,774.0 ms |
| 5 | 1,813.3 ms |
| 6 | 1,750.9 ms |
| 7 | 1,764.8 ms |
常常晚到的 device 1、2 確實累積了比較短的 NCCL duration,符合「等得少」的方向;但 device 4 並不是 NCCL 時間最短的卡。這也修正前兩天容易混在一起的兩個數字:device 4 的 1,094.7 ms 是 NCCL-only 時間,完整 NCCL kernel duration 其實是 1,803.9 ms。前者還會受到它和其他 GPU kernel 重疊位置的影響,不能只用遲到次數解釋。
換句話說,這幾張表回答的是不同問題。Day 19 的 device 4 overlap 最高,只能說它的 NCCL 有較高比例與其他 GPU kernel 同時執行;不能反推「它一定是拖慢大家的那張」。要找 late arriver,最直接的做法仍是把同一筆 collective 的開始與結束時間排在一起。

知道誰先到、誰晚到之後,下一個自然的問題是:這些時差累積起來有多大?本文採用一個簡化算法:同一筆 collective 取七張卡最短的 kernel duration 當傳輸基線,其餘 duration 超過基線的部分視為 start-skew 成本。
這和 AMD TraceLens 的 collective report 口徑相同:它以跨 ranks 的最短 duration 當 comm_latency,再把晚到造成的差異列為 wait time/start skew。OSDI 2025 的研究則以「共同的最晚開始時間到結束時間」估 transfer duration;在主檔 A 這種結束時間對齊到 0.12 ms 內的情況,兩種估法很接近。
主檔 A 的 stream 56 七卡合計如下:
七卡 NCCL kernel time: 12,227.7 ms
基線:每筆最短 duration × 7 卡: 8,765.0 ms
相對基線多出的 duration: 3,462.7 ms
相對占比: 28.3%
這個 28.3% 應該叫做 start-skew estimate,而不是絕對精準的「等待時間」。它有三個限制:
所以這個數字比較像「同步時差的溫度計」,不是可以直接從 step time 扣掉的預算。不過,它仍然很適合拿來看問題的形狀。把 3,462.7 ms 再拆一次:
開始差距 > 20 ms: 8 筆跨卡事件,約 1,854.6 ms
其餘事件: 217 筆跨卡事件,約 1,608.1 ms
八次大時差貢獻約 53.6%,其餘 217 次毫秒級差異合計約 46.4%。前者適合逐筆追 timeline,後者比較像長期排程與負載的穩定偏差,兩種問題不該混成同一個平均數處理。
也因為 Day 19 已經發現 communicator 次數對不攏,這裡不再拿最短 duration 和 900 GB/s 規格硬算「NVLink 使用率」。要判斷真正的傳輸效率,仍要先確認 communicator、message size、algorithm/protocol,再和同拓撲的 nccl-tests baseline 比較。
把開始差距超過 20 ms 的八筆 collective 放回五個 step:
| collective | 步內位置 | 發生次數 | 最後開始的 device |
|---|---|---|---|
| AllGather | 約 +460 ms | 5/5 steps | dev2、dev2、dev2、dev3、dev1 |
| ReduceScatter | 約 +518 ms | 3/5 steps | dev1、dev6、dev4 |
這張地圖很有辨識度:事件的位置固定,最後開始的卡卻一直換人。光看到這裡,很容易猜成某個 rank 的 Python、GC 或 CPU 排程偶爾停了約 50 ms;原稿也是這樣判斷。不過把 NCCL kernel 接回 CUDA runtime 後,故事不是這樣。
以 process ID 與 correlationId 配對後,這八筆 NCCL 的 cuLaunchKernelEx 都在 GPU kernel 真正開始前 236–297 ms 就已經完成。也就是說,CPU 早已把工作放進 CUDA 排程,並不是到了 +460/+518 ms 才臨時呼叫 NCCL。
GPU timeline 也顯示,最後抵達的 collective 都貼著 stream 21 上某個 GEMM 的尾端才開始:
| collective | NCCL stream | 同時段的 GEMM | 最後抵達 rank 上的 GEMM duration |
|---|---|---|---|
| AllGather | 56 | nvjet_tst_128x320_64x3_2x1_v_bz_coopB_NNN |
47.7–48.9 ms |
| ReduceScatter | 56 | nvjet_tst_192x192_64x3_2x1_v_bz_coopB_NTN |
50.0–52.7 ms |
把七張卡並排後,線索更明顯。在較早抵達的卡上,NCCL 會和這些 GEMM 重疊;在最後抵達的卡上,NCCL 則接近 GEMM 結束時才被排進 GPU。這比較像跨 stream 的 event dependency、CUDA hardware queue 對映,或 GEMM/NCCL 資源競爭造成的排程差異。只靠現有 trace 還無法分辨是哪一種,但至少可以排除「這八次都是 CPU 太晚呼叫 NCCL」。
OSDI 2025 的研究也記錄過 false kernel dependency:本來沒有資料相依的 kernel 因為共用 CUDA hardware queue 而互相阻塞,調整 CUDA_DEVICE_MAX_CONNECTIONS 後改善。不過這只能當 A/B test 的方向,不能直接套用成主檔 A 的診斷。
固定位置、裝置輪替也不太像某一張 GPU 持續降頻;GREYHOUND 的熱降頻案例是固定同一張 GPU 長期慢約兩成。可是主檔 A 只有五步、又缺 device 0,還不能據此宣布硬體完全健康。比較合理的優先順序是:先查這兩個固定位置的依賴與排程,同時保留 clock、溫度與 power throttle telemetry 來排除硬體問題。

查到這裡,嫌疑範圍已經從「不知道哪張卡慢」縮到兩個固定位置、兩種 GEMM,以及 GPU 排程。現有 profile 還看不出 CUDA stream 到底在等哪個 event,也沒有 CPU sampling、context switch 與完整 Python call stack。下一輪可以分四條線補資料:
cudaStreamWaitEvent、event record 和 graph node 接起來;再對 CUDA_DEVICE_MAX_CONNECTIONS 做受控 A/B test。TORCH_NCCL_TRACE_BUFFER_SIZE、TORCH_NCCL_ENABLE_TIMING 與 TORCH_NCCL_TRACE_CPP_STACK,補 process group、sequence number 與 C++ call stack。NCCL_DEBUG=INFO 與 NCCL_DEBUG_SUBSYS=INIT,GRAPH,TUNING 確認拓撲、algorithm 與 protocol,避免只憑 kernel symbol 猜設定。nvidia-smi 的 Clocks Event Reasons counters;只看某一瞬間的 Not Active 可能漏掉短暫降頻。Python GC 仍是多卡訓練常見的抖動來源。OSDI 2025 的案例觀察到不同 workers 會在不同 step 觸發 GC,Megatron-LM 也提供 --manual-gc 與 --manual-gc-interval。但對主檔 A 這八次事件來說,collective 的 CUDA launch 已經提早送出,所以 GC 不該排在目前的第一順位。
第一,把 NCCL kernel 最長的卡直接叫做 straggler。在「開始不齊、結束對齊」的型態裡,長 kernel 通常是先到後等待的 rank。要看的是同一筆 collective 的開始與結束,不是跨整段 profile 排總時間。
第二,把 anomaly 表格的 20 列當成 20 次事件。工具預設只回傳最慢 20 列,而且同一筆 collective 會在多張卡上各留一列;先跨卡分組,才能數真正的事件。
第三,看到 GPU kernel 晚開始,就認定 CPU 晚發射。主檔 A 的八次大時差裡,CUDA launch 早在 236–297 ms 前完成。GPU start 還會受 stream event、hardware queue 與資源排程影響,必須把 runtime 與 kernel correlation 接起來。
第四,把 28.3% 當成 step slowdown。它是七卡 stream 56 的 kernel-duration skew estimate,既是跨卡加總,也可能與其他 GPU 工作重疊;不能直接從 step time 扣掉。
今天把主檔 A 的 225 筆 stream 56 collective 逐筆對齊。最明顯的視覺特徵是:結束時間的 p50 差距只有 0.052 ms,開始時間的 p50 是 0.441 ms、最大卻到 53.234 ms。以跨卡最短 duration 當基線,start skew 約占七卡 NCCL kernel time 的 28.3%;其中一半集中在八次固定位置的大時差,另一半來自 217 次毫秒級差異。
這五步內沒有固定同一張卡包辦最後抵達,更重要的是,八次大時差的 NCCL launch 都早已由 CPU 送出,GPU kernel 卻在兩種 GEMM 尾端才開始。現在最值得追的是跨 stream 依賴、hardware queue 與資源競爭,而不是先怪 Python GC 或直接換卡。
Part D 的多卡三部曲到這裡收齊:Day 18 拆 collective 組成,Day 19 拆 overlap,今天拆跨 rank 的 start skew。明天換到 kernel 內部:Nsight Systems 已經指出可疑位置,接下來用 Nsight Compute 看單一 kernel 為什麼跑成現在這個樣子。
prims_simple.h
comm_latency 的工具先例:AMD TraceLens — Collective Report
nsys-ai v0.3.0-21-g1cc03b5 實跑 megatron.sqlite 的 39.964–46.123 秒;跨卡配對以 stream 56 七卡各 225 筆、操作序列零差異為前提。等待拆帳以各筆七卡最短 duration 為估計基線;CUDA runtime 與 kernel 以相同 process 加 correlationId 配對。